Log patron authorization identifier in uwsgi access logs by jonathangreen · Pull Request #3146 · ThePalaceProject/circulation

jonathangreen · 2026-03-17T17:57:30Z

Description

Sets a uwsgi logvar (AUTHORIZATION_IDENTIFIER) during patron authentication and updates the uwsgi log format to include it. This makes the patron identifier (library card barcode) visible in uwsgi access logs, aiding in troubleshooting authentication issues.

For Basic auth, sets AUTHORIZATION_IDENTIFIER to the submitted username before authentication, so it appears in logs even on failed 401 requests
On successful authentication, overwrites with patron.authorization_identifier, which may differ from the submitted username
For non-Basic auth flows (e.g., bearer tokens), sets AUTHORIZATION_IDENTIFIER from patron.authorization_identifier after successful authentication
Values are sanitized via str.translate() to prevent log injection (control characters, spaces, and double quotes are escaped as \xHH)

Motivation and Context

This would have helped while troubleshooting CM authentication errors. Without the patron identifier in access logs, it's difficult to correlate failed requests to specific patrons when investigating issues.

How Has This Been Tested?

New tests added for AUTHORIZATION_IDENTIFIER logvar behavior covering basic auth (success and failure) and non-basic auth flows
Tests for logvar sanitization (control characters, spaces, double quotes)
Test confirming graceful no-op when uwsgi module is unavailable

Checklist

I have updated the documentation accordingly.
All new and existing tests passed.

codecov · 2026-03-17T18:05:10Z

Codecov Report

❌ Patch coverage is 92.30769% with 1 line in your changes missing coverage. Please review.
✅ Project coverage is 93.26%. Comparing base (948ba8f) to head (28d39fa).

Files with missing lines	Patch %	Lines
src/palace/manager/api/controller/base.py	92.30%	0 Missing and 1 partial ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #3146      +/-   ##
==========================================
- Coverage   93.26%   93.26%   -0.01%     
==========================================
  Files         493      493              
  Lines       45586    45599      +13     
  Branches     6252     6254       +2     
==========================================
+ Hits        42518    42530      +12     
  Misses       1982     1982              
- Partials     1086     1087       +1

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

tdilauro

🧑‍🦱🪵

lgcassab · 2026-03-18T18:03:19Z

Code review

Found 1 issue:

%(user) in uwsgi log format will not reflect environ["REMOTE_USER"] set by the Python application (bug: uwsgi C struct vs Python environ mismatch)

The PR sets flask.request.environ["REMOTE_USER"] in Python and uses %(user) in the uwsgi log format to display it. However, uwsgi's %(user) log variable reads from wsgi_req->remote_user in the C wsgi_request struct, which is populated during initial protocol parsing (from variables sent by the front-end server/reverse proxy), not from the Python WSGI environ dict. Modifications to the Python environ dict do not propagate back to the C struct, so %(user) will always be empty (or show -) unless REMOTE_USER was already set by the upstream server (e.g., nginx).

The correct approach would be to use uwsgi.set_logvar('key', 'value') to set a per-request log variable from Python, and reference it in the log format via %(key). For example:
```
import uwsgi
uwsgi.set_logvar('remote_user', auth.username)
```
And in the log format:
```
log-format = ... %(remote_user) ...
```
References: uwsgi LogFormat docs, uwsgi logging.c source

circulation/src/palace/manager/api/controller/base.py

Lines 67 to 82 in 05f159b

    
           # Set REMOTE_USER for uwsgi access log visibility. We set this early, before 
        
           # authenticating the patron, so that we have the username on authentication failures. 
        
           if auth.type.lower() == "basic" and auth.username: 
        
               flask.request.environ["REMOTE_USER"] = auth.username 
        
           patron = self.authenticated_patron(auth) 
        
           if isinstance(patron, Patron): 
        
               setattr(flask.request, "patron", patron) 
        
               # Set REMOTE_USER again here for non-basic auth flows, using the patron's 
        
               # authorization identifier to provide detail in access logs. 
        
               if ( 
        
                   flask.request.environ.get("REMOTE_USER") is None 
        
                   and patron.authorization_identifier 
        
               ):

circulation/docker/services/uwsgi/uwsgi.d/40_log.ini

Lines 1 to 4 in 05f159b

    
           [uwsgi] 
        
           log-format = [uwsgi] %(var.HTTP_X_FORWARDED_FOR) (%(addr)) %(user) - [%(ltime)] "%(method) %(uri) %(proto)" %(status) %(size) "%(referer)" "%(uagent)" host_hdr=%(host) req_time_elapsed=%(msecs) process=%(pid) worker=%(wid) 
        
           logger = stdio: 
        
           logger = file:/var/log/uwsgi/uwsgi.log

jonathangreen · 2026-03-18T20:07:10Z

Hi @lgcassab, thanks for this review! You're spot on, the issue you flagged is exactly what I found during integration testing. If you look at the subsequent commits, I've made many of your suggested changes. I also added sanitization for log injection since uwsgi doesn't escape logvar values at all (control characters, spaces, etc.).

After all these changes, I've put this PR into draft, since I'd like to do a bit more testing, and I'm not sure if I want to merge this one, given the relatively small gain of information in log messages vs the amount of code we need here once you factor in sanitization and non-uwsgi use cases.

Out of curiosity, do you use Palace Manager? I don't think I've seen your name around here before.

Set an AUTHORIZATION_IDENTIFIER uwsgi logvar during patron authentication so the authenticated user appears in access logs. The logvar is set early in the auth flow (from basic auth username) to capture failed attempts, then overwritten with the patron's canonical authorization_identifier on success. Values are sanitized to prevent log injection.

jonathangreen · 2026-03-19T00:31:08Z

This is more complicated then my first pass, but I've wanted this to be able to cross reference logs a few times in the past, so I think its worth bringing in. I did a bunch of testing with uwsgi in docker to make sure this is working, and logs are being escaped as expected.

@tdilauro I re-requested another review on this, since its changed a fair bit from your first look at it.

tdilauro

Oof. They don't make it easy, do they.

jonathangreen added the feature New feature label Mar 17, 2026

jonathangreen requested review from a team March 17, 2026 17:59

tdilauro approved these changes Mar 18, 2026

View reviewed changes

jonathangreen force-pushed the feature/log-remote-user-in-uwsgi branch from 05f159b to bf67eaf Compare March 18, 2026 19:18

jonathangreen marked this pull request as draft March 18, 2026 19:58

jonathangreen force-pushed the feature/log-remote-user-in-uwsgi branch from a37067b to 89c4c60 Compare March 19, 2026 00:09

jonathangreen force-pushed the feature/log-remote-user-in-uwsgi branch from 022b2e4 to 28d39fa Compare March 19, 2026 00:24

jonathangreen changed the title ~~Log REMOTE_USER (patron identifier) in uwsgi access logs~~ Log patron authorization identifier in uwsgi access logs Mar 19, 2026

jonathangreen marked this pull request as ready for review March 19, 2026 00:29

jonathangreen requested a review from tdilauro March 19, 2026 00:29

tdilauro approved these changes Mar 19, 2026

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Log patron authorization identifier in uwsgi access logs#3146

Log patron authorization identifier in uwsgi access logs#3146
jonathangreen wants to merge 1 commit intomainfrom
feature/log-remote-user-in-uwsgi

jonathangreen commented Mar 17, 2026 •

edited

Loading

Uh oh!

codecov bot commented Mar 17, 2026 •

edited

Loading

Uh oh!

tdilauro left a comment

Uh oh!

lgcassab commented Mar 18, 2026

Uh oh!

jonathangreen commented Mar 18, 2026

Uh oh!

jonathangreen commented Mar 19, 2026

Uh oh!

tdilauro left a comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Conversation

jonathangreen commented Mar 17, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

Motivation and Context

How Has This Been Tested?

Checklist

Uh oh!

codecov bot commented Mar 17, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

tdilauro left a comment

Choose a reason for hiding this comment

Uh oh!

lgcassab commented Mar 18, 2026

Code review

Uh oh!

jonathangreen commented Mar 18, 2026

Uh oh!

jonathangreen commented Mar 19, 2026

Uh oh!

tdilauro left a comment

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

jonathangreen commented Mar 17, 2026 •

edited

Loading

codecov bot commented Mar 17, 2026 •

edited

Loading